MySQL 8 Observability 


(Also Query Troubleshooting with PMM Demo) 
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Why Observability 


Many Non Easily 
Repeatable Issues 


in Complex 
Systems 


Resolving and 
Preventing Issues 


Requires 
Understanding 
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Data Capture 


Ongoing Data Capture (Monitoring) 
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Comprehensive View Needed 


You Can't just use at MySQL Alone 


Application issues can’t be ignored 
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MySQL 8 at Focus 


MySQL 8 Data Sources 


INFORMATION 
SCHEMA 


PERFORMANCE 


SCHEMA 


EXPLAIN 


PERCONA 


SHOW [GLOBAL] STATUS 


Existed Forever 


Most are counters, some are gauges, some text 


Session and Global Scope 
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Global And Session 


mysql> select * from performance schema.global status where variable name='Questions' : 


1 row in set (0.01 sec) 


mysql» select * from performance schema.session status where variable name='Questions' ; 


1 row in set (0.00 sec) 
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Trust but Verify 


mysql> select * from performance schema.session status where 
variable name like "$rows$"; 


+-------------------------- 4---------------- + 
| VARIABLE NAME | VARIABLE VALUE | 
+-------------------------- 4---------------- + 
| Innodb rows deleted | 14553828 | 
| Innodb rows inserted | 15840851 | 
| Innodb rows read | 1927758552 | 
| Innodb rows updated | 29290781 | 
| Mysqlx rows sent | O | 
| Not flushed delayed rows | 0 | 
| Sort rows | 19 | 
+-------------------------- 4---------------- + 


7 rows in set (0.00 sec) 
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Status-Profiling Query 


mysql» select * from performance schema.session status where variable name like "$Handler read next$"; 
+------------------- +---------------- + 
| VARIABLE NAME | VARIABLE VALUE | 
+------------------- +---------------- + 
| Handler_read_next | 11 I 
+------------------- +---------------- + 


1 row in set (0.00 sec) 


mysql> select count(*) from orders1; 


+---------- + 
| count (*) | 
+---------- + 
| 75653 | 
4---------- * 


1 row in set (0.02 sec) 


mysql» select * from performance schema.session status where variable name like "$Handler read next$"; 
+------------------- +---------------- + 
| VARIABLE NAME | VARIABLE VALUE | 
+------------------- +---------------- + 
| Handler_read_next | 75664 l 
+------------------- +---------------- + 


1 row in set (0.00 sec) 
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VMSTAT Like output for MySQL 


root@mysql3:~# mysqladmin extended -i1 -r | grep Questions 


| Questions | 82525506 
| Questions | 378 
| Questions | 519 
| Questions | 591 


(2 PERCONA 


With Percona Toolkit 


root@mysql3:~# pt-mext -r -- mysqladmin ext -il -c5 


Bytes received 


Bytes sent 


Innodb buffer pool pages data 
Innodb buffer pool pages dirty 
Innodb buffer pool pages flushed 
Innodb buffer pool pages free 


12 


13701143412 
19638518220 


27615 
13643 
23741158 
964 
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54076 
98678 


-58 
-58 
182 

60 


101332 44687 
131670 94501 
-3 2 

86 -26 

145 123 

0 -2 


INFORMATION SCHEMA 


Some are Schema Related 


Others are Performance Statistics 
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INFORMATION SCHEMA - Shema Info 


mysql> select * from TABLES limit 1 \G 


kkkkkkkkkkkkkkkkkkkkkkkkkkk 1. 


TABLE CATALOG: 
TABLE SCHEMA: 
TABLE NAME: 
TABLE TYPE: 
ENGINE: 

VERSION: 

ROW FORMAT: 
TABLE ROWS: 

AVG ROW LENGTH: 
DATA LENGTH: 
MAX DATA LENGTH: 
INDEX LENGTH: 
DATA FREE: 

AUTO INCREMENT: 
CREATE TIME: 
UPDATE TIME: 
CHECK TIME: 
TABLE COLLATION: 
CHECKSUM: 


def 


CHARACTER SETS 
SYSTEM VIEW 
NULL 

10 


NULL 


o o o o o o 


NULL 


NULL 
NULL 
NULL 
NULL 


CREATE OPTIONS: 


TABLE COMMENT: 


1 row in set (0 


14 


.00 sec) 


LOW kk ok kk k dk kk k kk kk k ek ek k RAR 


information_schema 


2019-05-27 20:33:04 
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INFORMATION SCHEMA — Metrics 


mysql> select * 


kkkkkkkkkkkkkkkkkkkkkkkkkkk 1. 


NAME : 

SUBSYSTEM: 
COUNT : 

MAX COUNT: 

MIN COUNT: 

AVG COUNT: 

COUNT RESET: 

MAX COUNT RESET: 
MIN COUNT RESET: 
AVG COUNT RESET: 
TIME ENABLED : 
TIME DISABLED: 
TIME ELAPSED: 
TIME RESET: 
STATUS: 

TYPE: 

COMMENT : 


1 row in set (0 
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from innodb metrics limit 1 \G 


metadata_table handles opened 
metadata 

20040 

20040 

NULL 

0.10970542669608203 

20040 

20040 

NULL 

NULL 

2019-06-11 19:01:11 

NULL 

182671 

NULL 

enabled 

counter 

Number of table handles opened 
.00 sec) 


row KRKKKKKKKKKKKKKKKKKKKKKKKKEK 
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Note on Innodb Metrics 


While Looks similar to SHOW STATUS is not enabled by default 
e innodb_monitor_enable=all 
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Performance Shema 


100+ Tables 


Some information Capture Enabled by Default 


Can enable more instrumentation permanently or temporary 


Overhead can be high 


© 2021 Percona. 
17 (9 PERCONA 


Performance Schema Configuration 


mysql> show tables like "setups"; 


| setup actors | 
| setup consumers | 
| setup instruments | 
| setup objects | 
| setup threads | 
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Actors — What users should be profiled ? 


mysql> select * from setup actors; 


+------ +------ +------ +--------- +--------- + 
| HOST | USER | ROLE | ENABLED | HISTORY | 
+------ +------ +------ +--------- +--------- + 
| % | % | % | YES | YES | 
+------ +------ +------ +--------- +--------- + 
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What Summaries should be produced 


mysql> select * from setup consumers; 


+---------------------------------- +--------- + 
| NAME | ENABLED | 
+---------------------------------- +--------- + 
| events stages current | NO | 
| events stages history | NO | 
| events stages history long | NO | 
| events statements current | YES 

| events statements history | YES 

| events statements history long | NO | 
| events transactions current | YES | 
| events transactions history | YES | 


| events transactions history long | NO | 


| events waits current | NO | 
| events waits history | NO | 
| events waits history long | NO | 
| global instrumentation | YES 

| thread instrumentation | YES 

| statements digest | YES | 
+---------------------------------- +--------- + 


15 rows in set (0.00 sec) 
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Instruments - Instrumentation Points 


e 1200+ Instruments 
e 800 enabled by default and almost 300 timed 


mysql> select * from setup instruments limit 2 \G 
OTT Cn eee Or ane l. row ***'*** kk kk kek ke de ke ke e ke e e ke e ek e kv € 
NAME: wait/synch/mutex/pfs/LOCK pfs share list 
ENABLED: NO 
TIMED: NO 
PROPERTIES: singleton 
VOLATILITY: 1 


DOCUMENTATION: Components can provide their own performance schema tables. This lock protects the list of such tables definitions. 
kkkkkkkkkkkkkkkkkkkkkkkkkkk 2. row EE 
NAME: wait/synch/mutex/sql/TC LOG MMAP: :LOCK tc 
ENABLED: NO 
TIMED: NO 
PROPERTIES: 
VOLATILITY: 0 
DOCUMENTATION: NULL 


2 rows in set (0.00 sec) 
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What Objects to Instrument 


mysql> select * from setup_objects; 


4------------- +-------------------- +------------- +--------- +------- + 
| OBJECT_TYPE | OBJECT_SCHEMA | OBJECT_NAME | ENABLED | TIMED | 
+------------- +-------------------- +------------- +--------- +------- + 
| EVENT | mysql | & | NO | NO | 
| EVENT | performance schema | % | NO | NO | 
| EVENT | information_schema | % | NO | NO | 
| EVENT NE NEE | YES | YES | 
| FUNCTION | mysql | & | NO | NO | 
| FUNCTION | performance schema | % | NO | NO | 
| FUNCTION | information_schema | % | NO | NO | 
| FUNCTION ee | 3% | YES | YES | 
| PROCEDURE | mysql | 3 | NO | NO | 
| PROCEDURE | performance schema | % | NO | NO I 
| PROCEDURE | information schema | % | NO | NO | 
| PROCEDURE E l S | YES | YES | 
| TABLE | mysql | & | NO | NO | 
| TABLE | performance schema | % | NO | NO | 
| TABLE | information_schema | & | NO | NO | 
| TABLE | 3% | 3% | YES | YES | 
| TRIGGER | mysql | 3 | NO | NO | 
| TRIGGER | performance schema | % | NO | NO I 
| TRIGGER | information schema | % | NO | NO | 
| TRIGGER | Ñ | 3 | YES | YES | 
4------------- +-------------------- 4------------- 4--------- 4------- * 


20 rows in set (0.01 sec) 
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What Threads do we want to Instrument 


mysql> select * from setup_threads; 


| thread/performance schema/setup 

| thread/sql/bootstrap 

| thread/sql/manager 

| thread/sql/main 

| thread/sql/one connection 

| thread/innodb/srv error monitor thread 


| thread/innodb/srv lock timeout thread 


| thread/myisam/find all keys 

| thread/mysqlx/acceptor network 

| thread/mysqlx/worker 

| thread/sql/slave io 

| thread/sql/slave sql 

| thread/sql/slave worker 
E 


49 rows in set (0.00 sec) 
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om bos 
HISTORY | PROPERTIES 
sae e aa a 
YES | singleton 
YES | singleton 
YES | singleton 
YES | singleton 
YES | user 

YES | 

YES | 

YES | 

YES | 

YES | 

YES | singleton 
YES | singleton 
YES | singleton 
ST EE ===- 
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-—————— —— — — — — — — + 
DOCUMENTATION | 


Example of Performance Schema Data 


mysql> select * from events statements current limit 1 \G 
sek o o ok k ff ff k k k k kk 1. p y AEE ok a 
THREAD ID:9789 
EVENT ID:49 
END EVENT ID:49 
EVENT NAME: statement/sgl/show status 
SOURCE: init net server extension.cc:95 
TIMER START: 185174708798157000 
TIMER END: 185174709926911000 
TIMER WAIT: 1128754000 
LOCK TIME: 98000000 
SQL TEXT: SHOW GLOBAL STATUS 
DIGEST: 070e38632eb4444e50cdcbf0b17474ba801e203add89783a24584951442a2317 
DIGEST_TEXT: SHOW GLOBAL STATUS 
CURRENT_SCHEMA: NULL 


NESTING_EVENT_TYPE: NULL 
NESTING_EVENT_LEVEL:0 
STATEMENT_ID: 84449971 


1 row in set (0.00 sec) 
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Too Hard to Use ? 


Meet Sys Schema 


[92 PERCONA 


Sys Schema 


Views and Stored 
Procedures to access 


Performance Schema 
Data 


(©) PERCONA 


Views for Humans 


mysql> show tables; 
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host summary 

host summary by file io 

host summary by file io type 
host summary by stages 

host summary by statement latency 
host summary by statement type 
innodb buffer stats by schema 
innodb buffer stats by table 
innodb lock waits 

io by thread by latency 

io global by file by bytes 
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Views for Machines 


mysql> show tables like "x$%"; 


x$host summary 

x$host summary by file io 

x$host summary by file io type 
x$host summary by stages 

x$host summary by statement latency 


x$innodb buffer stats by schema 
x$innodb buffer stats by table 
x$innodb lock waits 


| 
| 
| 
| 
| 
| x$host summary by statement type 
| 
| 
| 
| x$io by thread by latency 

| 


x$io global by file by bytes 
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Example for Humans 


mysql> select * from session limit 1 \G 
kkkkkkkkkkkkkkkkkkkkkkkkkkk 1. 


thd_id: 

conn_id: 

user: 

db: 

command: 

state: 

time: 
current_statement: 
statement latency: 
progress: 

lock latency: 

rows examined: 
rows sent: 

rows affected: 

tmp tables: 

tmp disk tables: 
full scan: 

last statement: 
last statement latency: 
current memory: 
last wait: 

last wait latency: 
source: 

trx latency: 

trx state: 

trx autocommit: 
pid: 

program name: 

1 row in set (0.23 sec) 
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7101 
7060 


app2©1i1306-116 members .linode .com 


tpcc4 
Sleep 
NULL 


COMMIT 
97.95 us 
119.71 KiB 
NULL 
NULL 
NULL 

3.10 ms 
COMMITTED 
NO 

14124 
NULL 


LOW *kkkkkk kk kk kk kkk kk e ke ek e kk ek 
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Example for Machines 


mysql> select * from x$session limit 1 \G 
KEKKKKKKKEKKKKKKKKKEKKKKKKKKK n 


thd id: 

conn id: 

user: 

db: 

command: 

state: 

time: 

current statement: 
statement latency: 
progress: 


lock latency: 

rows examined: 
rows sent: 

rows affected: 

tmp tables: 

tmp disk tables: 
full scan: 

last statement: 
last statement latency: 
current memory: 
last wait: 

last wait latency: 
source: 

trx latency: 

trx state: 

trx autocommit: 
pid: 

program name: 


1 row in set (0.55 sec) 
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9122 
9081 


app1@1i1306-116 members .linode.com 


tpcc5 
Sleep 
NULL 
11 
NULL 


COMMIT 
1945326000 
172047 
NULL 

NULL 

NULL 
9264917000 
COMMITTED 
NO 

17713 

NULL 


row X*k k kkk kkk kkk kk kkk kkk kkk kkk 
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Information by Client Hosts 


mysql> select * from host summary XG 
*kckckckckckckckckckckckckckckck ck k k kk kkk*k*k T]. 
host: 

Statements: 

Statement latency: 
statement avg latency: 
table scans: 

file ios: 
file io latency: 
current connections: 
total connections: 
unique users: 

current memory: 


total memory allocated: 
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row *x* xxx kk ok k kk kk e ke kkk RARA AA 


1i11306-116.members.linode.com 


58027942 
9.56 h 
592.85 us 
296 
67522180 
1.45 h 

20 

148 

2 

18.39 MiB 
2.72 TiB 
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File IO by Hosts 


mysql> select * from host summary by file io; 


32 


background 


11174-63.members.linode.com 
111306-116.members.linode.com 
11534-125.members. linode.com 


localhost 


ercona. 


+ 


+ ————— L 


110954519 
33872913 
33795434 
33767097 

1138434 


———— eT — + 
10 latency | 
nn me ee + 
7.63 h | 
43.80 m | 
43.66 m | 
43.08 m | 
1.23 m | 
SS ms ni, mi mim: i + 


Types of IO 


mysql» select * from host summary by file io type; 


4------------------------------- +--------------------------------------------------- 4---------- 4--------------- 4------------- + 
| host | event_name | total | total_latency | max_latency | 
4------------------------------- +--------------------------------------------------- 4---------- 4--------------- 4------------- + 
| background | wait/io/file/innodb/innodb log file | 87369393 | 7.22 h | 430.95 ms | 
| background | wait/io/file/innodb/innodb data file | 22990098 | 16.77 m | 134.75 ms | 
| background | wait/io/file/innodb/innodb parallel dblwrite file | 387716 | 7.67 m | 115.12 ms | 
| background | wait/io/file/sql/binlog | 232529 | 2.09 s | 28.38 ms | 
| background | wait/io/file/innodb/innodb temp file | 415 | 49.44 ms | 2.32 ms | 
| background | wait/io/file/sql/slow log | 7 | 5.05 ms | 4.58 ms | 
| background | wait/io/file/sql/pid | 3 | 3.02 ms | 2.97 ms | 
| background | wait/io/file/sql/ERRMSG | 5 | 2.05 ms | 1.04 ms | 
| background | wait/io/file/sql/binlog index | 36 | 1.71 ms | 643.66 us | 
| background | wait/io/file/mysys/cnf | 5 | 1.58 ms | 1.27 ms | 
| background | wait/io/file/sql/casetest | 15 | 1.24 ms | 1.04 ms | 
| background | wait/io/file/mysys/charset | 3 | 426.80 us | 408.13 us | 
| background | wait/io/file/sql/misc | 1 | 48.61 us | 48.61 us | 
| 111306-116.members.linode.com | wait/io/file/sql/binlog | 3074720 | 19.91 m | 116.84 ms | 
| 1i1306-116.members.linode.com | wait/io/file/innodb/innodb data file | 1678043 | 15.42 m | 173.48 ms | 
| 111306-116.members.linode.com | wait/io/file/sql/slow log | 29049102 | 8.34 m | 75.98 ms | 
| 1i1306-116.members.linode.com | wait/io/file/sql/binlog index | 165 | 7.71 ms | 2.32 ms | 
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Statement Summary Per Host 


mysql> select * from host summary by statement latency G 


* ke cec ee ce ee e e ALA à x k kx kx x kx 1. 


host: 11174-63. 
total: 
total latency: 
max latency: 
lock latency: 
rows sent: 
rows examined: 
rows affected: 
full scans: 


members.linode.com 
29175532 

4.80 h 

51.14 s 

37.47 m 

13377371 

686152549 

20877010 

180 
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row 


Statement Types Per Host 


mysql> select host, statement, total,total latency,rows sent from host summary by statement type 
limit S; m m m BERN 


35 


background 


1i11306-116.members.linode. 
1i11306-116.members.linode. 
1i11306-116.members.linode. 
1i11306-116.members.linode. 


rows in set (0.02 sec) 


4 
| 
+ 
| 
| 
| 
| 
| 
+ 


select 
select 
update 
commit 
insert 


+————— + — + 


12812362 
6825577 
1325481 
5232533 
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----------- + 
rows sent | 


File IO 


mysql> select * from io global by file by bytes limit 10; 


| @@datadir/xb doublewrite 

| GGdatadir/mysq13-slow.log 

| @@datadir/tpcc5/order linel.ibd 
| GGdatadir/tpccl/order linel.ibd 
| GGdatadir/tpcc3/order linel.ibd 
| @@datadir/tpcc4/order_linel.ibd 
| GGdatadir/tpcc2/order linel.ibd 
| GGdatadir/tpcc5/stockl.ibd 

| GGdatadir/tpcc2/stockl.ibd 

| GGdatadir/tpccl/stockl.ibd 

EE See munem 


10 rows in set (0.02 sec) 
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342876 
341504 
335372 
327280 
320811 
398634 
397969 
398392 


+ 
| 
" 
| 
| 
| 


= === 
avg read | count write 
— fo- sam 
0 bytes | 194812 
0 bytes | 88694996 
16.00 KiB | 1769489 
16.00 KiB | 1765234 
16.00 KiB | 1770525 
16.00 KiB | 1708848 
16.00 KiB | 1619925 
16.00 KiB | 1370460 
16.00 KiB | 1371018 
16.00 KiB | 1368650 
EE JEE 
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298.55 GiB 
.25 
27. 
26. 
.02 
26. 
.72 
.91 
.92 
20. 


67 


27 


24 
20 
20 


00 
94 


07 


88 


GiB 
GiB 
GiB 
GiB 
GiB 
GiB 
GiB 


1.57 MiB 
814 bytes 


16. 
16. 
16. 
16. 
16. 
16. 
16. 
16. 


00 
00 
00 
00 
00 
00 
00 
00 


KiB 
KiB 
KiB 
KiB 
KiB 
KiB 


298.55 GiB 
.25 
32. 
.15 
.13 
.07 
.61 
.99 
199 
.96 


67 


32 


23 


GiB 
GiB 
GiB 
GiB 
GiB 
GiB 
GiB 


4----------- + 
| write pct | 


IO by Event 


mysql> select event name, total latency, total read,total written from io global by wait by latency 


limit 10; 
$-------------------------------------- E 
| event name | 
4---------------------2----------------- + 
innodb/innodb log file | 
innodb/innodb data file | 
sql/binlog | 
sql/slow log | 
innodb/innodb parallel dblwrite file | 
innodb/innodb temp file | 
sql/io cache | 
sql/binlog index | 
sql/pid | 
sql /ERRMSG | 
4---------------------2----------------- + 
10 rows in set (0.01 sec) 
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28.18 ms 
3.02 ms 
2.05 ms 


© 2021 Percona. 


+ 
| 
+ 
| 
| 
| 
| 
| 
| 
| 
| 
| 
| 
+ 


11.69 MiB 
86.82 GiB 
1.80 GiB 

0 bytes 
3.75 MiB 
592.00 KiB 
256.50 MiB 
3.95 KiB 

0 bytes 
273.98 KiB 


E——————————-4t4-— + 


Re M + 
total written | 
————— — — + 
42.61 GiB 
298.79 GiB 
17.64 GiB 
67.30 GiB 
298.78 GiB 
667.45 MiB 
256.50 MiB 
0 bytes 
6 bytes 
0 bytes 


Memory Allocation 


mysql> select event name, current count, current alloc from memory global by current bytes limit 10; 


memory/innodb/buf buf pool 

memory /temptable/physical ram 

memory /sql/TABLE 

memory performance schema/events statements summary by digest 
memory performance schema/events errors summary by thread by error 
memory /innodb/utOlink buf 

memory /performance schema/table handles 

memory /innodb/memory 
memory/performance schema/events errors summary by user by error 


memory/performance schema/events errors summary by host by error 


10 rows in set (0.01 sec) 


38 


© 2021 Percona. 


4--------------- 4--------------- + 
| current count | current alloc | 
4--------------- 4--------------- + 
| 4 | 533.00 MiB | 
| 95 | 95.00 MiB | 
| 19757 | 59.73 MiB | 
| 1 | 39.67 MiB | 
| 257 | 34.38 MiB | 
| 2 | 24.00 MiB | 
| 2 | 18.12 MiB | 
| 10443 | 17.96 MiB | 
| 129 | 17.19 MiB | 
| 129 | 17.19 MiB | 
4--------------- 4--------------- + 


Enhanced Metrics Table 


mysql> select * from metrics limit 10; 


+ a" T ee ae Vi fe E mom 
| Variable name 


aborted clients 

aborted connects 

acl cache items count 
binlog cache disk use 
binlog cache use 

binlog snapshot file 
binlog snapshot position 
binlog stmt cache disk use 
binlog stmt cache use 
bytes received 
+- 
10 rows in set (0.04 sec) 
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4414737 


mysql3-bin.000163 
871448732 


0 
382 


17290791216 


Global 
Global 
Global 
Global 
Global 
Global 
Global 
Global 
Global 
Global 
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Status 
Status 
Status 
Status 
Status 
Status 
Status 
Status 
Status 
Status 


--------- + 
Enabled | 


Processlist — Includes Background 


mysql> select * from processlist limit 1 \G 
kkkkkkkkkkkkkkkkkkkkkkkkxkxkxk 1. row eee ee ee eec ee ec e e M x e à e kx x kx kx 
thd id: 30 
conn id: NULL 
user: innodb/fts optimize thread 
db: NULL = z 
command: NULL 
state: NULL 
time: 229883 
current statement: NULL 
statement latency: NULL 
progress: NULL 
lock latency: NULL 
rows examined: NULL 
rows sent: NULL 
rows affected: NULL 
tmp tables: NULL 
tmp disk tables: NULL 
full scan: NO 
last statement: NULL 
last statement latency: NULL 
"^ current memory: 1.91 KiB 
last wait: NULL 
last wait latency: NULL 
"^ source: NULL 
trx latency: NULL 
trx state: NULL 
trx autocommit: NULL 
= pid: NULL 
program name: NULL 
1 row in set (0.30 sec) 
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Do not run out of auto_increment space 


mysql» select * from schema auto increment columns \G 
kkkkkkkkkkkkkkkkkkkkkkkkxkxkxk 1. row X*k xkxk kkk kkk e e ke ke ee e e ke à à à kkk 
table schema: sbtest 
table name: sbtestl 
column name: id 
data type: int 
column type: int(11) 
is signed: 1 
is unsigned: 0 
max value: 2147483647 
auto increment: 1000000 
auto increment ratio: 0.0005 
l row in set (0.01 sec) 
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Redundant Indexes 


mysql> select * from schema redundant indexes VG 
* ce ce e ee ce e e e e e kv e e e ke x 1. row KKRKKKKKKKKKKKKKEKEKEKKKKKKKKK 


table schema: 

table name: 
redundant index name: 
redundant index columns: 
redundant index non unique: 
dominant index name: 
dominant index columns: 
dominant index non unique: 
subpart exists: 

sql drop index: 


k 1° 
1 row in set (0.05 sec) 
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sbtest 
sbtest1 


ALTER TABLE sbtest . sbtestl DROP INDEX 
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Table Access Statistics 


mysql> select * from schema table statistics limit 5 \G 
cce ck ce ck e ke ce e ce e e ke ke ke ke ke kv kx ke kx kx xk kx 1. row kk kk kk ZZ k k KR 


table schema: 
table name: 

total latency: 
rows fetched: 
fetch latency: 
rows inserted: 
insert latency: 
rows updated: 
update latency: 
rows deleted: 
delete latency: 
io read requests: 
= ^ io read: 
io read latency: 
io write requests: 
m “io write: 
io write latency: 
io misc reguests: 
io misc latency: 
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tpccl 

new ordersl 
15.37 m 
857480 

7.19 m 
288180 


8041 
125.64 MiB 
3.39 s 
6873 

1.68 s 
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Unused Indexes 


mysql> select * from schema unused indexes where 
object schema-'tpccl'; 


4--------------- 4------------- +-------------------- + 
| object schema | object name | index name | 
+--------------- +------------- $-------------------- + 
| tpccl | historyl | fkey history 11 | 
| tpccl | order linel | fkey order line 21 | 
| tpccl | stockl | fkey stock 21 | 
$--------------- +------------- +-------------------- e 


3 rows in set, 1 warning (0.02 sec) 
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Are you using SSL ? 


mysql» select * from session ssl status limit 10; 


4----------- 4------------- +-------------------- +--------------------- + 
| thread id | ssl_version | ssl_cipher | ssl_sessions_reused | 
+----------- +------------- +-------------------- +--------------------- + 
| 12152 | TLSv1.1 | DHE-RSA-AES256-SHA | O | 
| 12158 | | | O | 
| 12159 | | | O | 
| 12160 | | | O | 
| 12005 | TLSv1.1 | DHE-RSA-AES256-SHA | O | 
| 12006 | TLSv1.1 | DHE-RSA-AES256-SHA | O | 
| 12007 | TLSv1.1 | DHE-RSA-AES256-SHA | O | 
| 12008 | TLSv1.1 | DHE-RSA-AES256-SHA | O | 
| 12011 | TLSv1.1 | DHE-RSA-AES256-SHA | O | 
| 12012 | TLSv1.1 | DHE-RSA-AES256-SHA | O | 
4----------- 4------------- +-------------------- +--------------------- + 


10 rows in set (0.00 sec) 
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Statements info 


mysql> select * from statement_analysis limit 5,1 \G 
kkkkkkkkkkkkkkkkkkkkkkkkkkk 1. row X kck kk ke k ke ARA A X 


query: 
db: 
full scan: 


SHOW GLOBAL STATUS 


NULL 
* 


exec count: 240568 
err count: 0 
warn count: O0 
total latency: 20.88 m 
max latency: 153.12 ms 
avg latency: 5.21 ms 
lock latency: 1.70 m 
rows sent: 117878320 
rows sent avg: 490 
rows examined: 235756640 
rows examined avg: 980 
rows affected: O0 
rows affected avg: 0 
tmp tables: 240568 
tmp disk tables: 0 
rows sorted: 0 
sort merge passes: 0 


070e38632eb444 4e50cdcbf£0b1 747 4ba801e203add89783a24584951442a2317 
first_seen: 2019-06-11 19:01:32.245462 
last_seen: 2019-06-14 13:50:07.158611 

1 row in set (0.01 sec) 


digest: 
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Errors and Warnings ? 


mysql» select * from statements with errors or warnings limit 1 \G 
* ecce ee ee e e e e ke e à e kv ke x kk kk kkkk 1. row kk ok ke kk kkk kkk kkk kkk kk kk 
query: SELECT no o id FROM new ord ... o o id ASC LIMIT ? FOR UPDATE 
db: tpccl 
exec count: 298942 
errors: 7 
error pct: 0.0023 
warnings: 0 
warning pct: 0.0000 
first seen: 2019-06-11 19:02:31.104121 
last seen: 2019-06-14 13:52:57.834563 
digest: 366d8c4aa612adf0ec3e06cb020fd395eldalfd4f6b676530c214771aed00b55 
1 row in set (0.01 sec) 
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User Info 


mysql> select * from user summary limit 1 \G 
kkkkkkkkkkkkkkkkěkkkkkkkkkkkk 1. row HAL E kk RE 


user: 
Statements: 

statement latency: 
statement avg latency: 
table scans: 

file ios; 
file io latency: 
current connections: 
total connections: 
unique hosts: 

current memory: 

total memory allocated: 
1 row in set (0.08 sec) 
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appl 
195012171 
1.38 d 
612.32 us 
1428 
226986594 
4.96 h 

36 

476 

B 

125.39 MiB 
9.13 TiB 
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More Wait Info (If Enabled) 


mysql» select events, total, total latency from waits global by latency limit 10; 


$--------------------------------------------------- 4------------ 4--------------- E 
| events | total | total latency | 
$--------------------------------------------------- 4------------ 4--------------- + 
| wait/io/file/innodb/innodb log file | 108966439 | 9.17 h | 
| wait/io/table/sgl/handler | 2615937816 | 5.41 h | 
| wait/io/file/innodb/innodb data file | 34980007 | 1.35 h | 
| wait/io/file/sgl/binlog | 11738591 | 1.25 h | 
| wait/io/file/sql/slow log | 109842706 | 32.11 m | 
| wait/io/file/innodb/innodb parallel dblwrite file | 483426 | 9.70 m | 
| wait/lock/table/sql/handler | 101720352 | 2.82 m | 
| wait/io/file/innodb/innodb temp file | 24212 | 39.62 s | 
| wait/io/file/sql/io cache | 18961 | 2.29 s | 
| wait/io/file/sql/binlog index | 731 | 38.33 ms | 
$--------------------------------------------------- 4------------ 4--------------- E 


10 rows in set (0.01 sec) 
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Latency Distributions 


mysql> select * from 


events statements histogram global limit 1 \G 
ccce ce ke e e e ke x e ke kx kx kx k kk kkkkk 1. row 
kkkkkkkkkkkkkkkkkkkkkkkkxkkxk 


BUCKET NUMBER: 
BUCKET TIMER LOW: 
BUCKET TIMER HIGH: 


COUNT BUCKET: 
COUNT BUCKET AND LOWER: 
BUCKET QUANTILE: 


1 row in set (0.00 sec) 
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0 

0 
10000000 
162125 
162125 
0.001473 
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Logs 


Error Log 


Slow Query Log 
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Slow Query Log (Percona Server) 


# Time: 2019-06-14T14:07:29.062441Z 

+ User@Host: appl[appl] © 11534-125.members.linode.com [50.116.47.125] Id: 7442 
# Schema: tpccl Last errno: O Killed: 0 

+ Query time: 0.000635 Lock time: 0.000123 Rows sent: 0 Rows examined: 0 Rows affected: 1 
# Bytes sent: 11 Tmp tables: 0 Tmp disk tables: 0 Tmp table sizes: 0 

+ InnoDB trx id: 366322C 

# Full scan: No Full join: No Tmp table: No Tmp table on disk: No 

# Filesort: No Filesort on disk: No Merge passes: 0 

# InnoDB IO r ops: 0 InnoDB IO r bytes: O InnoDB IO r wait: 0.000000 

# InnoDB rec lock wait: 0.000000 InnoDB queue wait: 0.000000 

# InnoDB pages distinct: 7 

SET timestamp=1560521249; 

INSERT INTO order linel 


(ol o id, ol d id, ol w id, ol number, ol i id, ol supply w id, 
ol quantity, ol amount, ol dist info) © EE == - —— = eg um 


VALUES (181228,6,1,9,31509,1,3,169,'xXXXXXXXXXXXXXXXXXXXXXXX'); 
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MySQL 8.0.14+ Extends Slow Query Log 


# Time: 2019-06-14T14:14:22.980797Z 
# User@Host: root[root] @ localhost [] Id: 8 


# Query time: 0.005342 Lock time: 0.000451 Rows sent: 33 
Rows examined: 197 Thread id: 8 Errno: 0 Killed: 0 
Bytes received: 0 Bytes sent: 664 Read first: 1 Read last: 
O Read key: 71 Read next: 127 Read prev: 0 Read rnd: 33 
Read rnd next: m m 


34 Sort merge passes: 0 Sort range count: 0 Sort rows: 33 
Sort scan count: 1 Created tmp disk tables: 0 m 
Created tmp tables: 1 Start: 2019-06-14T14:14:22.9754552Z 


End: 2019-06-14T14:14:22.980797Z 
SET timestamp=1560521662; 
show tables; 
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EXPLAIN 


Understand Query Execution Plan 


Multiple Output Formats 


Can get EXPLAIN plan for actual running query 
mE (3 Percona 


Basic Explain 


mysql> explain SELECT o c id 


FROM ordersl 


AND o w id = 1 VG 
ok ck cec cec ec ec ec e ke e ke ke e e ke | kx kx kx kk 1. row *x*x* xx xx kx kxk e kk kk kk kk RE 


id: 

select type: 
table: 
partitions: 
type: 
possible keys: 
key: 

key len: 
ref: 

rows: 
filtered: 
Extra: 


1 row in set, 
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L 

SIMPLE 

ordersl 

NULL 

const 
PRIMARY, idx ordersl 
PRIMARY 

7 

const, const,const 
1 

100.00 

NULL 


1 warning (0.00 sec) 
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WHERE o id = 180962 


AND o d id = 10 


JSON Explain 


mysql> explain format=json SELECT o c id 


WHERE o id = 180962 
AND o w id = 1 MG 
kkkxkkkkkkkkkkkkkkkkkkkkkkkk 1 . 
EXPLAIN: ( 
"query block": ( 
"select id": 1, 
"cost info": ( 
"query cost": "1.00" 
}, 


"table": { 
"table name": "orders1", 
"access type": "const", 
"possible keys": [ 
"PRIMARY", 


"idx orders1" 
1, 
"key": "PRIMARY", 
"used key parts": [ 
"o w id", 


"key length": "7", 
"ref" a [ 
"const", 
"const", 
"const" 
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FROM orders1 
AND o d id = 10 


LOW **k*kkkk kk k kkk ck kc ke KK kkk kkk kkk 


} 


1, 
"rows examined per scan": 1, 
"rows produced per join": 1, 
"filtered": "100.00", 
"cost info": ( 
"read cost": "0.00", 
"eval cost": "0.10", 
"prefix cost": "0.00", 
"data read per join": "24" 
}, 
"used columns": [ 
"o id", 
"o d id", 
"o w id", 
"o c id" 


1 row in set, 1 warning (0.02 sec) 
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TREE Format (8.0.16+) 


EXPLAIN: -> Aggregate: count (0) 
-> Filter: ((tl.cl + tl.c ytd payment) <> tl.sm) 
-> Table scan on t1 
-> Materialize 
-> Index lookup on c using PRIMARY (c w id=1) 
-> Select #3 (subquery in projection; dependent) 
-> Aggregate: sum(order linel.ol amount) 
-> Nested loop inner join 
-> Index lookup on ordersl using idx ordersl (o w id =c.c w id, o d id=c.c d id, o c id=c.c id) 
-> Filter: ((order linel.ol d id = ordersl.o d id) and (order linel.ol w id = ordersl.o w id) and 
(order linel.ol delivery d is not null)) 
-> Index lookup on order linel using PRIMARY (ol .W id-c.c w id, ol d id-c.c d id, 


ol o id=ordersl.o id) 
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EXPLAIN ANALYZE 


mysql> EXPLAIN ANALYZE SELECT * FROM t1 JOIN t2 ON (t1.c1 = t2.c2)\G 


AA AAA AA A A A kk AAA A A A A A AA RR À row AX ZX AZ AZ ko ko ko ko kock kk k kk A Á AZ Z Z Z AZ ÁZ Á XX 


EXPLAIN: -> Inner hash join (t2.c2 = t1.c1) (cost=4.70 rows=6) 
(actual time=0.032..0.035 rows=6 loops-1) 

-> Table scan on t2 (cost=0.06 rows=6) 
(actual time=0.003..0.005 rows=6 loops=1) 

-> Hash 


-> Table scan on t1 (cost=0.85 rows=6) 
(actual time=0.018..0.022 rows=6 loops=1) 


EXPLAIN FOR CONNECTION 


mysql [localhost] {msandbox} CCnone)) > explain for connection 9 
KKK K K K K KK K K KKK KKK KKK KKK KKK 1. row 2K K K OK K K K K K K K K K K K K K K K K K K K K K K K 
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id: X 
select_type: SIMPLE 
table: employees 
partitions: NULL 
type: ALL 
possible_keys: NULL 
key: NULL 
key len: NULL 
ref: NULL 
rows: 299540 
filtered: 100.00 
Extra: NULL 
FK K K 2K 2 k K K OK OK OK K K ok KOK K K OK OK OK KKK 2. row KA K K 2K K K K K K K OK K K K OK OK K K OK KOK KE KOK KK 
tal 
select type: SIMPLE 
table: salaries 
partitions: NULL 
type: ALL 
possible keys: NULL 
key: NULL 
key len: NULL 
ref: NULL 
rows: 2803840 
filtered: 100.00 
Extra: Using where; Using join buffer (Block Nested Loop) 
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Tracing Optimizer 


# Turn tracing on (it's off by default): 


SET optimizer trace="enabled=on"; 
DMO x uy 
# your query here 


SELECT * FROM 
INFORMATION SCHEMAOPTIMIAER TRACE 


# possibly more queries... 
# When done with tracing, disable it: 
SET Optimizer Trace="enabled=orLr™, 


https://dev.mysql.com/doc/internals/en/optimizer-tracing. html 
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Percona Monitoring and Management 


Open Source Database Focused 
Observability Solution from Percona 


PERCONA 


Monitoring and Management 


http://per.co.na/PMM 
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Demo Time 
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Want to learn more about PMM 


wu Come to Percona Booth to see the Demo and get your questions 
af- answered 


Our team can also can help you to install PMM 


If you have PMM installed already we can give you some tips on how to 
use it to improve your database 


TO 
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Custom Dashboards shown in the Demo 


https://www.percona.com/blog/2020/11/02/understanding- 


mysql-memory-usage-with-performance-schema/ 


https://www.percona.com/blog/2021/04/22/understanding- 


processes-running-on-linux-host-with-percona-monitoring-and- 
management/ 


https://Www.percona.com/blog/2020/07/15/mysal-query- 


performance-troubleshooting-resource-based-approach/ 


https://www.percona.com/blog/2020/06/17/red-method-for- 


mysql-performance-analyses/ 
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Which Queries are Causing the Loa 


Filter by... vá Query v 


TOTAL 34.83 load 2.74k QPS 


Environment 


mytest 99.99% update warehouse’ set w_ytd = w_ytd + ? where w_id =? PP PE PA NBA IR tdt Lob alo 10.99 load 24.03 QPS 


n/a <0.01% select i price, i name, i data from item1 where i, id = ? Eé SE KEE DER GE GEN 4.95 load 241.47 QPS 


Database select c from sbtest1 where id=? E TFT a M TT T ill 3.15 load 988.38 QPS 


n/a 99.99% select d next o id, d tax from district! where d w. id = ?... ab hs Lu d al 2.87 load 24.17 QPS 


postgres «0.0196 | i i 
update district1 set d ytd = d ytd + ? where d_w_id =? a... io. bolo ee RP ee PE | P 2.41 load 24.02 QPS 


pmm-managed <0.01% 
select o id from orders1 o, (select o_c_id,o_w_id,o_d_id.... LO Tn FUNT PATI CRI I Te a 1.62 load 24.23 QPS 


Schema Show all (7) 
insert into new. orders1 (no. o. id, no. d id, no. w. id) valu... BELLI LI dia 1.14 load 24.17 QPS 


tpcc1 44.2% , 
insert into order line1 (ol. o. id, ol d id, ol. w id, ol numb... PP PR TE 0.93 load 241.23 QPS 


tpcc5 11.4196 


tpcc4 11.4% update stock) set s quantity = ? where s i id = ? ands EN a Le ds 0.83 load 241.23 QPS 


tpcc2 11.2996 


tpcc3 11.296 10/pagev 1-10 of 325 items 
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Why Are they Causing this Load 


Details Examples Explain Tables 


v Query time distribution 


Lock Time: 98.91% 


v Metrics 


Metric Rate/Second Sum Per Query Stats 


Query Count @ 24.06 QPS | 1.04m 0.88% of total 1.00 


Query Count with errors (0 <0.01 QPS 345.00 0.03% of total 
5 days, 12:01:41 
31.55% of total 


5 days, 10:35:06 
Lock Time 10.88 (avg load) ist. batt E LL 1 le 58.07% of total 


Query Time i) 11.00 load 


Rows Examined i) 24.06 (per sec) 
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to Improve their Performance 


Expand All 


"query block": - 
SELECT DISTINCT c = 


FROM sbtest1 “cost infot: F 
WHERE id “ordering operation” 
BETWEEN 5559 "using filesort": false 


"duplicates removal": - 


AND 2658 CREATE TABLE "sbtesti ( "using temporary table": true 
ORDER BY c “id” int(10) unsigned NOT AUTO INCREMENT, "using filesort": true 


"k^ int(10) unsigned NOT DEFAULT 'Q', Sx uS NE 


"c char(120) NOT DEFAULT '', 
“pad” char(60) NOT DEFAULT '', 
PRIMARY KEY (id), 
KEY ^k I Ck) 
) ENGINE=InnoDB AUTO INCREMENT-100000001 DEFAULT 


"table": + 
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System Monitoring 


Node Summary - 


System Uptime Virtual CPUs ` Load Average Disk Space : Min Space Available 2 Time before run out of space 


24.06 GiB 


Memory Available Virtual Memory DB Service Connections 


2.46 GiB 


Service Types 


Amount 


CPU Usage CPU Saturatioi id Max Core Usage 


E E SU Vp vy ver v vum AA m p Um xe Lie 
75.00% 


BR 30.00 75.00% 


100.00% 


50.00% 20.00 


10.00 


11:00 1 00 17:00 18:00 19:00 20:00 
10:00 12:00 13:00 14:00 15:00 1 19:00 20:00 


malized CPU Load 


Max CPU Core Utilization 


Interrupts and Context Switches Processes 


30.00 Ln 


10.00K 


40.00 
) 


150.00 ops 
0 


20.0 
00 ops 
09:00 11:00 1 ) 16:00 17:00 1 19:0 20:0 


11:00 0 16:00 17:00 18:00 19:00 10:00 2:00 13:00 14:00 


8:00 


© 2021 Percona. 


68 oj PERCONA 


MySQL Instance Summary 
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MySQL Instance Summary - 


auto * 


Home Dashboard Node Summary 


Connections 


09:00 10:00 11:00 


Max Connections 


— Max Used Connections 


Client Threads 


onnected 


unning 


74.207.232.64/graph 


PMM Annotations 


MySQL Instance Summary 


MySQL Uptime 


MySQL Connections 


14:00 15:00 16:00 


MySQL Client Thread Activity 


14:00 15:00 16:00 


Version 


8.0.19-10 


17:00 19:00 


93.00 


5.00 


93.00 


Current QPS 


953.96 


10:00 11:00 


Aborted Connects (attempts) 


= Aborted C (timeout) 


09:00 10:00 11:00 


96.19 Thread Cache Size 


70.86 = Threads Cached 
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Query Analytics 


InnoDB Buffer Pool Size 


256 MiB 


MySQL Aborted Connections 


14:00 15:00 


MySQL Thread Cache 


14:00 15:00 16:00 


4 Compare 


Buffer Pool Size of Total RAM 


20:00 


0.41 ops 


0.36 ops 


20:00 


9.00 9 9.00 


6.00 9.00 


PERCONA 


Advanced Performance Schema Analyses 


600 ops 


500 ops 


400 ops 


300 ops 


200 ops 


100 ops 


Oops 


MySQL Performance Schema Wait Event Analyses - 


Data for 


with resolution 


Count - Performance Schema Waits 


Load - Performance Schema Waits 
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min 


wait/io/file/innodb/innodb_log_file 422.88 ops 


wait/io/file/innodb/innodb_log_file 


max avg“ 


514.78 ops 479.42 ops 


min max avg” 


0.15 0.36 0.23 


Innodb Insights 


> MySQL InnoDB Details - 


Home Dashboard Node Summary MySQL Instance Summary MySQL InnoDB Compression Details 


mysgl1-mysgl mysql1 1m 


Buffer Pool Size Buffer Pool Size of Total R... Total Redo Log Space Max Log Space Used Max Transaction History Le... Data Bandwidth Fsync Rate Row Lock Blocking 


256 MiB 2.00 GiB 9.52 MBs 364.19 ops 31.68% 


InnoDB Activity 


Writes (Rows) Writes (Transactions) Row Writes per Trx Rows Read Per Trx Log Space per Trx Rollbacks BP Reqs Per Row Log Fsync Per Trx 


3.96% 3.03% 19.41 15.06 11.90 KiB 10,56 


InnoDB Row Reads InnoDB Row Writes 


15,00 K 500.00 


10.00K 
200.00 
100.00 
0 
20:00 


18:00 


updated 562 2 160.65 
inserted 5.07 90.33 
Rows operation 349K  1409K 780K 
InnoDB Read-Only Transactions InnoDB Read-Write Transactions 
1.00 K 
20.00 
15.00 
500.00 
10.00 


250.00 
19:00 0 20:30 0 9 19:30 20:00 


= Non Locking RO Transaction Commits 389.75 784.29 499.47 RW Transactioi 


RO Transaction Commits 1.93 10.27 5.02 — Rollback Rate 
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See it Live! 


https://pmmdemo.percona.com 
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Thank You! 
Twitter: @percona @peterzaitsev 


